Skip to content

Conversation

@quexten
Copy link
Contributor

@quexten quexten commented Nov 12, 2025

🎟️ Tracking

https://bitwarden.atlassian.net/browse/PM-28135

📔 Objective

Enables tracing, but does not yet remove the old logging (follow-up). It adds tracing to the most important crypto paths. Follow-up tickets may add more tracing.

Example log output:

ERROR log{cipher_id=Some(CipherId(18c99ec6-af2b-407a-a5d0-b39201386413))}:decrypt: bitwarden_crypto::traits::decryptable: Function returned error error=The cipher's MAC doesn't match the expected value

__wbg_error_a7f8fbb0523dae15 @ bitwarden_wasm_internal_bg.js:4508
$func7041 @ 43dc2d8abaf76eb338eb.module.wasm:0x2c3395
$func3785 @ 43dc2d8abaf76eb338eb.module.wasm:0x297ed0
$func232 @ 43dc2d8abaf76eb338eb.module.wasm:0xa3c75
$func6915 @ 43dc2d8abaf76eb338eb.module.wasm:0x2c23e3
$func2456 @ 43dc2d8abaf76eb338eb.module.wasm:0x2687b1
$func817 @ 43dc2d8abaf76eb338eb.module.wasm:0x1b8e06
$func192 @ 43dc2d8abaf76eb338eb.module.wasm:0x5ce74
$func2995 @ 43dc2d8abaf76eb338eb.module.wasm:0x27f181
...

⏰ Reminders before review

  • Contributor guidelines followed
  • All formatters and local linters executed and passed
  • Written new unit and / or integration tests where applicable
  • Protected functional changes with optionality (feature flags)
  • Used internationalization (i18n) for all UI strings
  • CI builds passed
  • Communicated to DevOps any deployment requirements
  • Updated any necessary documentation (Confluence, contributing docs) or informed the documentation
    team

🦮 Reviewer guidelines

  • 👍 (:+1:) or similar for great changes
  • 📝 (:memo:) or ℹ️ (:information_source:) for notes or general info
  • ❓ (:question:) for questions
  • 🤔 (:thinking:) or 💭 (:thought_balloon:) for more open inquiry that's not quite a confirmed
    issue and could potentially benefit from discussion
  • 🎨 (:art:) for suggestions / improvements
  • ❌ (:x:) or ⚠️ (:warning:) for more significant problems or concerns needing attention
  • 🌱 (:seedling:) or ♻️ (:recycle:) for future improvements or indications of technical debt
  • ⛏ (:pick:) for minor or nitpick changes

@quexten quexten changed the title Km/tracing Add crypto tracing logs Nov 12, 2025
@github-actions
Copy link
Contributor

github-actions bot commented Nov 12, 2025

Logo
Checkmarx One – Scan Summary & Detailsc499643d-a748-4eaa-9b04-e7797f3651c1

Great job! No new security vulnerabilities introduced in this pull request

@quexten quexten changed the title Add crypto tracing logs [POC] Add crypto tracing logs Nov 12, 2025
@codecov
Copy link

codecov bot commented Nov 12, 2025

Codecov Report

❌ Patch coverage is 75.00000% with 1 line in your changes missing coverage. Please review.
✅ Project coverage is 79.39%. Comparing base (7f09fd2) to head (6515170).

Files with missing lines Patch % Lines
crates/bitwarden-core/src/key_management/crypto.rs 75.00% 1 Missing ⚠️
Additional details and impacted files
@@            Coverage Diff             @@
##             main     #555      +/-   ##
==========================================
- Coverage   79.52%   79.39%   -0.14%     
==========================================
  Files         302      302              
  Lines       32366    32190     -176     
==========================================
- Hits        25739    25556     -183     
- Misses       6627     6634       +7     

☔ View full report in Codecov by Sentry.
📢 Have feedback on the report? Share it here.

🚀 New features to boost your workflow:
  • ❄️ Test Analytics: Detect flaky tests, report on failures, and find test suite problems.
  • 📦 JS Bundle Analysis: Save yourself from yourself by tracking and limiting bundle sizes in JS merges.

@quexten quexten changed the title [POC] Add crypto tracing logs [POC|PM-28135] Add crypto tracing logs Nov 13, 2025
@quexten quexten marked this pull request as ready for review November 13, 2025 14:36
@quexten quexten requested review from a team as code owners November 13, 2025 14:36
@quexten quexten requested a review from a team as a code owner November 13, 2025 14:36
@quexten
Copy link
Contributor Author

quexten commented Nov 13, 2025

Note: This has some overlap with #550, as this also enables tracing. The linked PR enables tracing and removes log.

Copy link
Member

@dani-garcia dani-garcia left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Looks pretty reasonable to me, just got some small comments.

@Hinton
Copy link
Member

Hinton commented Nov 13, 2025

Do we have any concerns about runtime performance? I think tracing negatively impacts performance but they have ways to indicate some should be compiled out, https://docs.rs/tracing/latest/tracing/level_filters/index.html#compile-time-filters.

(I suspect tracing performance to be a drop in the bucket for the crypto operations but I think this is a worthwhile discussion to have)

@claude
Copy link

claude bot commented Nov 13, 2025

Claude finished @quexten's task —— View job


Code Review Complete

I've completed my review of the PR. Here are my findings:


Summary

This PR adds tracing instrumentation to key cryptographic operations while maintaining the old logging system temporarily. The implementation is focused and adds structured logging to critical paths: user crypto initialization, encryption/decryption, and COSE operations. The approach is sound with appropriate use of #[instrument] macros and compile-time log level filtering.


Previous Review Comments Status

Addressed:

  • ✅ Using #[instrument(err)] instead of custom error logging macro (dani-garcia's suggestion)
  • ✅ Using skip_all consistently for sensitive data (dani-garcia's suggestion)
  • ✅ Set release_max_level_info to compile out debug/trace logs (Hinton's performance concern)

Not Addressed:
The automated review from claude-bot suggested changes that haven't been fully implemented:

Finding 1: The root Cargo.toml doesn't explicitly enable the attributes feature for tracing (workspace line 82), though it works via default features. This is a minor style issue, not a breaking problem.

Finding 2: The WASM init_sdk() function doesn't use try_init() to handle multiple initialization calls gracefully. This could cause panics if called twice, though it may not be an issue in practice if the client only calls it once.


Critical Issues

None identified.


Code Quality Findings

Finding 1: Missing attributes feature declaration for tracing

In the root Cargo.toml:82, the tracing dependency relies on default features for #[instrument] support:

tracing = { version = "0.1.41" }

Recommendation: Explicitly enable the attributes feature for clarity and to avoid breakage if defaults change:

tracing = { version = "0.1.41", features = ["attributes"] }

Finding 2: Potential panic on multiple WASM SDK initialization

In crates/bitwarden-wasm-internal/src/init.rs:45-49, calling .init() will panic if the tracing subscriber is already initialized:

tracing_subscriber::registry()
    .with(perf_layer)
    .with(filter)
    .with(fmt)
    .init();

Recommendation: Use try_init() with error handling to gracefully handle re-initialization:

if tracing_subscriber::registry()
    .with(perf_layer)
    .with(filter)
    .with(fmt)
    .try_init()
    .is_err()
{
    // Already initialized, which is acceptable
}

Finding 3: Inconsistent span creation pattern

In crates/bitwarden-core/src/key_management/crypto.rs:171-175, the code manually creates a span and enters it:

let _span_guard = tracing::info_span!(
    "User Crypto Initialization",
    user_id = ?client.internal.get_user_id(),
    method = ?req.method
)
.entered();

This is fine, but consider whether this function should use #[instrument] instead for consistency with other functions. The manual span approach is appropriate here because the function has complex control flow and you're adding structured fields that reference client (not a parameter).


Security Considerations

Good: All #[instrument] attributes use skip_all to avoid logging sensitive data (keys, passwords, etc.)

Good: Structured fields in spans only log IDs and types, not actual cryptographic material

Good: Error logging via err attribute won't expose key material (errors are already redacted)


Good Practices Observed

  • Consistent use of #[instrument(err, skip_all)] pattern across crypto operations
  • Appropriate compile-time log level filtering (release_max_level_info) to prevent performance impact
  • Structured logging with meaningful context (cipher_id, org_id, user_id)
  • Following Rust 2024 edition guidelines
  • Good separation of concerns (tracing only in key paths)

Architecture Notes

The dual-logging approach (keeping old logging + adding tracing) is reasonable for a POC. The follow-up ticket should:

  1. Remove old log crate usage
  2. Add more comprehensive tracing coverage
  3. Consider adding tracing to more boundary operations (API calls, state changes)

Testing Recommendations

Since this is infrastructure code affecting WASM and native builds:

  1. Verify WASM initialization doesn't panic on repeated calls (Finding 2)
  2. Test that log output appears correctly in browser console (WASM)
  3. Verify release builds actually compile out debug/trace logs
  4. Test performance impact on large vault decryption operations

Action Items

Optional (Low Priority):

  1. Add explicit attributes feature to tracing dependency (Finding 1)
  2. Use try_init() in WASM init to prevent panic on re-initialization (Finding 2)

Documentation:
3. Consider adding a comment explaining why manual span creation is used in initialize_user_crypto vs #[instrument]


Conclusion

This is a well-executed POC that adds valuable observability to critical crypto paths. The implementation follows best practices for security (no sensitive data in logs) and performance (compile-time filtering). The two optional findings are minor improvements that don't block merging.

The PR successfully enables tracing infrastructure that will support better debugging and performance analysis going forward.


@quexten
Copy link
Contributor Author

quexten commented Nov 14, 2025

@Hinton My biggest concern would be if tracing somehow is blocking with respect to the subscribers, and we would log a lot (possibly having to go to JS every time via the hooking to console it uses), though a quick check suggests that it just appends to a buffer that then gets flushed, and actual logs should not be that frequent with the current implementation.

Is there specific things that you'd like to see measured here? Vault unlock times for large vaults? Actual logs should only be emitted for errors / rare info events, but obviously the context is still stored into a buffer somewhere.

@Hinton
Copy link
Member

Hinton commented Nov 14, 2025

@quexten Comparing calling decrypt 100'000 times with tracing to 100'000 without in a test maybe? I think it's a drop in the bucket. But I feel like it's probably not necessary to be honest.

I do think it's good to decide if we want any of the release_max_level_ enabled since they would change behaviour. And anything lower than the value would be excluded from release builds and probably safe to use in abundance.

@quexten
Copy link
Contributor Author

quexten commented Nov 17, 2025

@Hinton Okay, I've not further benchmarked it since I agree that it's most likely negligible. I've set the max log level to release_max_level_info, since I don't think anyone would expect trace / debug to be emitted in release.

In case we do want logging in an operation that gets called millions of times, we should consider using debug/trace to have it compiled out in release.

@github-actions
Copy link
Contributor

github-actions bot commented Nov 17, 2025

🔍 SDK Breaking Change Detection Results

SDK Version: km/tracing (6515170)
Completed: 2025-12-02 14:14:07 UTC
Total Time: 217s

Client Status Details
typescript ✅ No breaking changes detected TypeScript compilation passed with new SDK version - View Details

Breaking change detection completed. View SDK workflow

@quexten quexten marked this pull request as draft December 1, 2025 17:07
@quexten quexten marked this pull request as ready for review December 2, 2025 13:51
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

4 participants